会议记录|使用Ftrace研究Linux内核

阅码场Ftrace公开课火热报名中：Ftrace公开课：学优化，学内核（限50人）。课程报名累计30+，课程报名即将截止，报名咨询客服（小月微信:linuxer2016）。

个人介绍：王建峰，平时我对于技术方向（主要是嵌入式领域的OS方向的系统应用）感兴趣，最近在学习ftrace技术。同时也是某芯原厂的驱动工程师，主要是gpu领域的驱动软件。

说明背景

文档作为会议的记录和补充，会议主题是《使用Ftrace研究Linux内核》，主讲人谢欢。回放链接

基本内容

1、Ftrace整体框架

根据官方文档的定义，Ftrace是一个内部跟踪器，旨在帮助系统的开发者和设计者去观测内核的运行。它可以被用于调试或分析发生在用户空间之外的延迟和性能问题。随着发展，目前已经演变成为一个基础的调试框架（支持多个不同类型的trace功能）。

直观理解有两层含义：一是提供函数钩子的基础设施，二是基于tracefs文件系统的trace框架。

• function tracer：在函数头挂钩子函数

• function graph tracer：可以带时间戳函数执行流打印

• kprobe：一般是挂在函数入口点，用于获取参数

• trace event：函数执行时调用静态的钩子函数

• kretprobe：通常是函数出口点，执行钩子函数

2、使用方式

Ftrace通过tracefs文件系统的控制文件来进行调试。如果内核构建阶段配置ftrace，默认会挂载tracefs到/sys/kernel/tracing，也可以在运行环境手动挂载

接下来的内容我会根据课程介绍，整理出ftrace不同功能的使用案例，一些问答和和观点以及个人对课程总结。 

function tracer使用

case01: 过滤"vfs_open"函数

观察结果：图示能看到所有执行vfs_open的跟踪信息。

function graph tracer使用

case01: 函数"vfs_open"的执行时间

echo vfs_open > ./set_ftrace_filter # 过滤要跟踪的函数
echo function_graph > ./current_tracer # 设置当前使用的tracer
echo 1 > ./options/funcgraph-proc # 启用进程TASK/PID打印
cp trace /test.txt && cat /test.txt

观察结果：查看到vfs_open被执行的调试信息包括TASK/PID，函数的执行时间在，接口名。原理上是通过在函数的入口点和出口点（kprobe/kretprobe）挂钩子来实现的。

case02: 函数"vfs_open"向下执行流

echo > ./set_ftrace_filter # 不使用过滤!!!
echo vfs_open > ./set_graph_function #  使用函数图表
echo function_graph > ./current_tracer # 过滤要跟踪的函数
echo 1 > ./options/funcgraph-proc # 打印进程TASK/PID
echo 1 > ./options/funcgraph-tail # 尾部注释(方便观察)
cp trace /test.txt && cat /test.txt

观察结果：vfs_open被执行时，能看到向下的执行流程，其中涉及到的函数调用和相关信息会打印出来。 

kprobe event

case01: 查看"vfs_open"当前打开文件名

# 理论计算：
# $arg1, 第一个参数
# +0x8($arg1), 地址偏移+0x8
# +0x70(+0x8($arg1)), 相当与C语言的 *(*($arg1 + 0x8) + 0x70)

echo 'p vfs_open name=+0x70(+0x8($arg1)):string namep=+0(+0x60(+0x8($arg1))):string' > ./kprobe_events
echo 1 > ./events/kprobes/p_vfs_open_0/enable
echo > trace && cat /test.txt
cp trace /test.txt && cat /test.txt

观察结果：图示看到一些vfs_open函数的kprobe事件，name是当前被查看的文件名。kprobe通过参数加地址偏移计算拿到特定成员的地址

case02: 捕获"vfs_open"查看指定文件的信息的事件

# 功能: 利用filter和trigger文件
root@debian:/sys/kernel/debug/tracing# ls ./events/kprobes/p_vfs_open_0/
enable filter format hist id inject trigger

# 格式: kprobe event
root@debian:/sys/kernel/debug/tracing# cat ./events/kprobes/p_vfs_open_0/format

echo 'p vfs_open name=+0x70(+0x8($arg1)):string namep=+0(+0x60(+0x8($arg1))):string' > ./kprobe_events
echo 1 > ./events/kprobes/p_vfs_open_0/enable # 过滤包含"test"字段的文件的事件
echo 'name ~ "*test*"' > ./events/kprobes/p_vfs_open_0/filter
echo > trace && cat /test.txt
echo 'stacktrace if name ~ "*test*"' > ./events/kprobes/p_vfs_open_0/trigger  # 包含"test"字段的文件的事件会触发"stacktrace"堆栈打印

trace event

cat /sys/kernel/debug/tracing/available_events # 查看当前支持的跟踪事件列表

case01: 打开驱动中跟踪节点

echo 1 > /sys/kernel/debug/tracing/events/gsgpu/enable && \
echo 0 > /sys/kernel/debug/tracing/trace && \
/root/run_test.sh ; cp /sys/kernel/debug/tracing/trace /test.txt && \
echo 0 > /sys/kernel/debug/tracing/events/gsgpu/enable
cat /test.txt

case02: 通过filter过滤事件

echo 0 > /sys/kernel/debug/tracing/events/gsgpu/enable && \
echo 1 > /sys/kernel/debug/tracing/events/gsgpu/gsgpu_bo_move/enable && \
echo 0 > /sys/kernel/debug/tracing/trace && \
echo "bo_size >= 50000" > /sys/kernel/debug/tracing/events/gsgpu/gsgpu_bo_move/filter && \
/root/run_test.sh ; cp /sys/kernel/debug/tracing/trace /test.txt && \
echo 0 > /sys/kernel/debug/tracing/events/gsgpu/gsgpu_bo_move/filter
cat /test.txt

case03: 通过trigger查看栈回溯

echo 0 > /sys/kernel/debug/tracing/events/gsgpu/enable && \
echo 1 > /sys/kernel/debug/tracing/events/gsgpu/gsgpu_bo_move/enable && \
echo 0 > /sys/kernel/debug/tracing/trace && \
echo 'stacktrace' > /sys/kernel/debug/tracing/events/gsgpu/gsgpu_bo_move/trigger && \
/root/run_test.sh ; cp /sys/kernel/debug/tracing/trace /test.txt && \
echo '!stacktrace' > /sys/kernel/debug/tracing/events/gsgpu/gsgpu_bo_move/trigger && \
cat /test.txt

objtrace

case01：观察对象数据在函数中流动

源码位置：https://github.com/x-lugoo/linux/tree/objtrace-v9

[root@JeffXie tracing]# cat ./events/kprobes/p_bio_add_page_0/trigger 
Available triggers: traceon traceoff snapshot stacktrace enable_event disable_event hist objtrace

cd /sys/kernel/debug/tracing/
echo 'p bio_add_page arg1=$arg1 arg2=$arg2' > ./kprobe_events
echo 'objtrace:add:arg1,0x28:u32:5 if comm == "cat"' > ./events/kprobes/p_bio_add_page_0/trigger
# du -sh /test.txt // 12K
cat /test.txt > /dev/null
cat ./trace

观察结果：参数arg1对应object对象，由于有kprobe匹配到目标参数达到触发条件，我看到图示中打印的调试信息。 这样就可以观察到指定接口的参数在内核函数中是怎样流动的

一些观点 

• 1、ftrace很多功能在国内使用不充分，比如tracer网上资料少，ftrace功能很强大，可挖掘的潜力大。像是大家对shell的使用，如果大家能积累更多的案例，这样能更好的普及和使用。

• 2、ftrace和正常的日志环形缓冲区不同，如果大量日志向同一个缓冲区输入，一会导致信息混乱，二是容易覆盖有效数据。使用ftrace的过滤等功能，可以更好的解决此类问题（适用更加复杂的业务场景）。补充ftrace其他功能：自动保存结果输出到文件；生成直方图；触发其他事件；等等。

• 3、ftrace对内核的通用性还是比较强的，相比ebpf来说ftrace对于低版本的内核更加友好。

• 4、ftrace的用户群体大，但是名声没有ebpf的功能大。

• 5、ftrace的tracer在linux中使用shell脚本来实现，如果想要观察和定位，使用这种手段方便；如果转发类或者做业务相关的，推荐使用ebpf比较多。可以根据各自优势应用到不同的场景，也可以两者结合使用。 

一些问答

问

perf/ftrace/ebpf关系

答

基于kprobe的ebpf通过  fd找到字节码程序，当perf使用相同功能的时候，可以依据 fd来找到这个字节码程序。基于kprobe的ebpf本质上是基于ftrace，   使用ftrace框架来调用字节码程序

# 使用bpftrace工具将ebpf程                                   序挂载到"kprobe:do_                             nanosleep"bpftrace -e                             'kprobe:do_nanosleep {                              printf("PID %d sleeping...\n",                                pid); }'

问

kprobe和function trace的钩子有什么区别？

答

基本相同，kprobe的钩子函数会做更多的解析工作，例如解析更多的 field(例如argN或stackN等)

问

什么是no trace函数？

答

如果函数本身参与ftrace功能，不能用于trace(避免递归) 这样的函数一般都是no trace。

问

uprobe是用什么实现的？

答

uprobe在用户层，基于断点指令来实现。

问

ftrace对性能影响多大?

答

看如何使用？如果对所有函数使用function tracer，如果只使用一个性能事件性能消耗很小。

问

如果从学习内核的角度来讲，怎样把ftrace作为一个辅助的工具来上手内核？

答

在调试内核的时候，通常使用printk/printf来使用，使用ftrace的前提要戒掉这个习惯，然后使用ftrace工具来调试。

问

对于可靠性和安全性比较高的领域，对于ftrace是不是要慎用一些？

答

是的，对原理理解要求比较高一些。对原理比较清楚的话，能很好的缩小ftrace的使用范围，来进一步降低对系统的性能消耗。

问

如何评估这些调试工具的开销?

答

正确对待ftrace是一个辅助工具，前提还是要对代码比较熟悉，ftrace辅助对代码的观察。

问

ftrace这样的工具好处？

答

使用在不破坏内核的情况下，提供一个对内核可观测手段；提供基础的tracer功能，灵活运用好tracer功能对分析问题帮助；perf工具将各种类型的挂载点收入囊中，一统江湖。

问

linux内核中有这么多钩子？都有什么局限，如何选择

答

看具体想使用哪些功能，比如查看函数怎么执行，选择function tracer；比如查看某一个函数的参数，使用kprobe挂载点对应的钩子函数不一样的。

问

ftrace的tracer在linux中使用shell脚本来实现，如果想要观察和定位，使用这种手段方便；如果转发类或者做业务相关的，推荐使用ebpf比较多

答

各有优势，应用到不同的场景，也可以两者结合使用。

问

在嵌入式场景，内存资源比较紧张的时候适用么？

答

内存消耗比较小。也可以设置，buffer可以调小一些。

问

ftrace在性能消耗比ebpf更小么？

答

也不一定，看使用那部分功能。

问

有没有推荐的日志化性能分析的图形工具？

答

tracecmd和KernelShark。

个人总结 

内核源码中放置很多静态跟踪节点，这些节点可以被关联到对应的回调函数。当我想要调试某个子系统/模块时，通过debug系统将对应的节点开启（将回调函数挂钩子到静态跟踪点上，与之关联），这样内核在执行到跟踪点位置的时候会调用钩子函数，最终执行结果将被输出写到一个环形日志缓存区里，通过debug系统查看信息。

作为一种内核层面的调试手段，trace event利用了ftrace框架，算是ftrace的一个应用吧。当我想要调试某一个模块，开启对应的节点就好了，trace event基于现有的跟踪节点（一般是写代码的添加好的）效率高些，或者解决新的bug时将关键调试信息固化到调试系统里。

从做工作的角度，我能体会到的是trace event工具能带来工作效率的提升。从学习的角度，我相信使用ftrace工具能更加方便观测内核。

往期精华文章：【精华】Linux阅码场原创精华文章汇总

阅码场付费会员专业交流群

会员招募：各专业群会员费为88元/季度，权益包含群内提问，线下活动8折，全年不定期群技术分享（普通用户直播免费，分享后每次点播价为19元/次），有意加入请私信客服小月（小月微信号：linuxer2016）

专业群介绍：

彭伟林-阅码场内核性能与稳定性本群定位内核性能与稳定性技术交流，覆盖云/网/车/机/芯领域资深内核专家，由阅码场资深讲师彭伟林主持。

甄建勇-性能优化与体系结构

本群定位Perf、cache和CPU架构技术交流，覆盖云/网/车/机/芯领域资深用户，由阅码场资深讲师甄建勇主持。

邓世强-Xenomai与实时优化

本群定位Xenomai与实时优化技术交流，覆盖云/网/车/机/芯领域资深用户，由阅码场资深讲师邓世强和彭伟林共同主持。

周贺贺-Tee和ARM架构

本群定位Tee和ARM架构技术交流，覆盖云/网/车/机/芯领域资深用户，由阅码场资深讲师周贺贺主持。

✦

✦